Tomáš Pospíšek's Notizblock

ssh takes long to log in

At some point ssh login to one of our Debian jessie servers began to take very long. It would get stuck on the client side at:

$ ssh -vv hostX -p $SOME_ARBITRARY_PORT
[...]
debug2: channel 0: send open
[...and 25 seconds later...]
debug1: Entering interactive session.

On the server side:

# /usr/sbin/sshd -d -p $SOME_ARBITRARY_PORT
[...]
debug1: PAM: establishing credentials
[...and 25 seconds later...]
debug1: packet_set_postauth: called

In the auth log we can find that sshd is doing something with PAM.

# tail -f /var/log/auth.log
[...]
Jun 18 13:39:01 hostX sshd[28911]: pam_unix(sshd:session): session opened for user userX by (uid=X)

PAM debugging can be turned on by touching /etc/pam_debug:

# touch /etc/pam_debug

Now we can see that PAM tries to access systemd's login service over dbus...

# tail -f /var/log/daemon.log
[...]
Jun 18 13:39:01 hostX dbus[15012]: [system] Activating via systemd: service name='org.freedesktop.login1' unit='dbus-org.freedesktop.login1.service'
Jun 18 13:39:01 hostX systemd[1]: Started Login Service.

...and times out 25 later...

# tail -f /var/log/auth.log
[...]
Jun 18 13:39:26 hostX sshd[28911]: pam_systemd(sshd:session): Failed to create session: Connection timed out
# tail -f /var/log/daemon.log
[...]
Jun 18 13:39:26 hostX dbus[15012]: [system] Failed to activate service 'org.freedesktop.login1': timed out

One workaround is to disable PAM in sshd_config:

# cat /etc/ssh/sshd_config
[...]
UsePAM no
[...]

This problem looks like https://github.com/NixOS/nixpkgs/issues/30348 and https://github.com/systemd/systemd/issues/2863 and has been fixed in systemd v235 https://github.com/systemd/systemd/pull/7102#issuecomment-347023412 which is not included in Debian jessie:

# dpkg -s systemd | grep Version
Version: 215-17+deb8u13

Tomáš Pospíšek, 2019-06-18